Skip to content

Audit trail for message actions (retry, archive, unarchive, edit)#5570

Open
ramonsmits wants to merge 32 commits into
authfrom
audit-message-actions
Open

Audit trail for message actions (retry, archive, unarchive, edit)#5570
ramonsmits wants to merge 32 commits into
authfrom
audit-message-actions

Conversation

@ramonsmits

@ramonsmits ramonsmits commented Jul 2, 2026

Copy link
Copy Markdown
Member

Records every user-initiated retry, edit, archive, and unarchive action as a structured audit entry attributed to the initiating user (or anonymous when authentication is disabled). Each invocation produces one operation entry (who / what / scope) plus one message entry per message actually acted on. Message entries are emitted at execution time — after the message is really retried, edited, or archived — including for bulk/group operations resolved in the background and resumed after a restart. Both entry kinds share an operation id so an operation can be traced through to every message it affected. A group request that is ignored because the same operation is already in progress is not audited.

Audit output

Entries are written to audit.json (one ECS-formatted JSON object per line) and to the console, on dedicated log categories ServiceControl.Audit (operations) and ServiceControl.Audit.Messages (per-message), so the audit stream can be shipped to a SIEM independently of the operational log. Successful actions log at Information, failures at Warning. The operation entry is written after the action is performed, so outcome records what actually happened — failure when the underlying send fails (the request then also fails).

Example — retrying all messages (operation entry followed by one entry per staged message):

{"@timestamp":"2026-07-03T12:18:54.0412345+00:00","event":{"kind":"event","category":["configuration"],"type":["change"],"action":"error:messages:retry","outcome":"success"},"user":{"id":"d4c3b2a1-56f8-4c11-9a3e-2b7d0c4e8f01","name":"alice@example.com"},"servicecontrol":{"permission":"error:messages:retry","scope":"all","operation":{"id":"0HN7GK3M8QABC:00000042"}}}
{"@timestamp":"2026-07-03T12:18:54.0898765+00:00","event":{"kind":"event","category":["configuration"],"type":["change"],"action":"error:messages:retry","outcome":"success"},"user":{"id":"d4c3b2a1-56f8-4c11-9a3e-2b7d0c4e8f01","name":"alice@example.com"},"servicecontrol":{"permission":"error:messages:retry","scope":"all","message":{"id":"3f2504e0-4f89-11d3-9a0c-0305e82c3301"},"operation":{"id":"0HN7GK3M8QABC:00000042"}}}
  • event.type is change for retry/edit/unarchive and deletion for archive; outcome is success or failure.
  • Operation entries carry scope (single/batch/queue/endpoint/all/group/range), and where applicable resource and count; message entries carry message.id and the scope of the initiating operation. Null-valued fields are omitted.

Settings

  • LogPath — directory for audit.json (alongside the operational log). The file archives daily or above 30 MB, keeping the last 14 archives. In containers the audit trail goes to the console only (no file).
  • LogLevel — controls operational verbosity only. The audit trail is always captured from Information upward, so lowering LogLevel never drops audit entries.

Correlation

Each operation's id is the ASP.NET request id (TraceIdentifier) and is returned on every response as the Request-Id header (exposed via CORS on all instances). The same value appears in servicecontrol.operation.id on the operation entry and every per-message entry, so a caller can correlate a single API call to each affected message and to the request's other logs. For a retry forwarded to a remote instance (instance_id), the returned Request-Id is the remote instance's request id, matching the audit entries recorded on that instance.

Emit a per-message IMessageActionAuditLog.MessageAction for every message
actually retried, archived, or unarchived, attributed to the initiating
user and correlated to the operation entry via an operation id.

- Wire the AuditHeaders stamp/read seam into the async command pipeline;
  persist the initiating user + operation id on RetryBatch and the
  Archive/Unarchive operation documents so bulk/group operations resolved
  by background schedulers (and resumed after restart) stay attributed.
- Emit per-message entries at the execution choke points (RetryProcessor
  staging, MessageArchiver batch loop, and the archive/unarchive/pending
  handlers) instead of at the API, so each message is logged exactly once
  when it is actually acted on.
- Use the ASP.NET Core request id (HttpContext.TraceIdentifier) as the
  operation id and return it as a Request-Id response header on all three
  instances (exposed via CORS) so callers can correlate.
@ramonsmits ramonsmits changed the title Message-action audit trail (retry/archive/unarchive) Audit trail for message actions (retry, archive, unarchive) Jul 3, 2026
Set JsonIgnoreCondition.WhenWritingNull on both audit logs so unset fields
(resource/count/message) are dropped rather than emitted as null. Idiomatic
ECS, and trims the high-volume per-message stream.
@ramonsmits ramonsmits requested review from WilliamBZA and dvdstelt July 3, 2026 12:21
@ramonsmits ramonsmits marked this pull request as ready for review July 3, 2026 13:35
@fredricadell

Copy link
Copy Markdown

This looks very good I think. But as I understand it, if we activate the edit message function, just make sure that the information/data that's been edited is included in the audit. Otherwise I think this is fine!

@WilliamBZA WilliamBZA left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Approval dependent on:

@ramonsmits ramonsmits changed the title Audit trail for message actions (retry, archive, unarchive) Audit trail for message actions (retry, archive, unarchive, edit) Jul 6, 2026
ramonsmits added 10 commits July 6, 2026 18:56
… queue

The registration lived only in AddServiceControlAuthorization, which is
called by RunCommand alone. The --import-failed-errors host consumes the
same input queue with all handlers registered, so any pending recoverability
command (ArchiveMessage, UnArchiveMessages, EditAndSend, ...) failed handler
activation and was moved to the error queue.

Move the registration to the primary AddServiceControl so every host that
can activate the recoverability handlers has it, and add a startup-mode test
asserting all RecoverabilityComponent handlers can be activated from the
import host's container (via ActivatorUtilities, mirroring NServiceBus).
ToArchiveOperation/ToUnarchiveOperation rebuilt the operation document from
the in-memory progress state, which does not carry InitiatedById/
InitiatedByName/OperationId, and MessageArchiver stored that stripped copy
over the original after every batch. A restart mid-operation then resumed
with no attribution and silently skipped the per-message audit entries of
all remaining batches — the exact scenario the persisted fields exist for.

The attribution is now passed into the mapping explicitly so no call site
can drop it, and tests snapshot the persisted document after the first
batch (the state a restart resumes from) for both archive and unarchive.

Also fixes an IDE0055 formatting error in EditHandlerAuditTests that broke
the ServiceControl.Persistence.Tests.RavenDB build.
PendingRetriesHandler emitted per-message retry entries when it resolved
the ids and then sent RetryMessagesById without the audit headers. That
recorded messages as retried that might never be staged (e.g. claimed by a
concurrent batch), and severed the attribution chain so the staged batch
carried no OperationId — the execution-time entries every other retry path
emits were never produced.

The handler no longer audits (and no longer needs the audit log); it
re-stamps the audit headers on the follow-up command so the batch carries
the attribution and RetryProcessor emits the per-message entries when the
messages are actually staged, like all other retry paths.

Also corrects the stale comments on RetryBatch.OperationId and
AuditStagedMessages claiming single/explicit-id retries leave OperationId
null — every path threads it; only legacy unstamped commands are null.
A retry forwarded to a remote instance (instance_id routing) is audited on
the remote under the remote's TraceIdentifier, and YARP copies that
Request-Id back onto the response — but the middleware's OnStarting callback
overwrote it with the local proxy's TraceIdentifier, handing the caller an
operation id that no audit entry on any instance matches. The header is now
set only when absent.

The identical middleware was pasted into all three instances; it now lives
once in ServiceControl.Hosting (UseRequestIdHeader) next to the other
cross-instance pipeline extensions, and the header name constant replaces
the magic string in the three CORS exposed-header lists.
The group archive/unarchive/retry controllers emitted the success operation
entry before the IsOperationInProgressFor guard, so a request ignored as a
no-op (operation already running, double-click) was still recorded as a
successful operation attributed to the caller — with an operation id that
never gains any per-message entries. The audit entry is now emitted inside
the guard, next to the work it describes.
Every controller wrote the operation entry with the implicit success
outcome before performing the send, so a transport failure returned HTTP
500 with nothing enqueued while the trail already claimed success — and
the failure outcome was dead code no production path could ever emit.

Controllers now run the action through AuditedOperation, which executes
the send and records the entry afterwards with the actual outcome
(failure + rethrow when the send throws). The stamped local SendOptions
ritual repeated at every call site is collapsed into
AuditHeaders.LocalSendOptions.
The per-message edit entry was emitted right after the failed message was
marked resolved but before the edited message was dispatched, so a
dispatch failure (transport down) left a success entry for an edit whose
message never went anywhere — repeated on every redelivery. The entry is
now emitted after the dispatch, so each audit entry corresponds to an
actual dispatch of the edited message.
A batch archive fans out into one ArchiveMessage command per id, and the
handler hardcoded scope 'single' on the per-message entries while the
operation entry said 'batch' — the only path where per-message scope did
not match the originating operation (unarchive batch/range, group and
retry paths all propagate it). The command now carries the operation's
scope; the default (Single) keeps legacy in-flight commands and the
single-archive endpoint correct.
The test archived group B and immediately unarchived it, but
UnarchiveDocumentManager.GetGroupDetails reads ArchivedGroupsViewIndex,
which is async — on a slow runner the index hadn't seen the archive yet,
so the unarchive logged 'No messages to unarchive' and no-opped, message B
expired along with A, and the wait for exactly one remaining message timed
out (observed on Linux-PrimaryRavenPersistence; Windows passed).

Wait for indexing between the archive and the unarchive, like the test
already does after ingestion.
MessageAction/Operation built the full ECS JSON document (timestamp
formatting, anonymous object graph, reflection-based serialization) before
the source-generated log method's internal IsEnabled check — wasted work
for every message of a bulk retry/archive when the operator filters the
high-volume ServiceControl.Audit.Messages category, which the class
explicitly supports. The level check now runs first.

Also shares the single EcsJsonOptions with AuthorizationAuditLog (the PR
already had to retrofit WhenWritingNull onto one copy to keep the two
streams consistent) and replaces the per-entry scope
ToString().ToLowerInvariant() with constant names.

Tests pin the contracts these changes could break: per-outcome level
semantics under a Warning category filter, and the exact lowercase scope
mapping for every MessageActionScope value.
@ramonsmits ramonsmits requested a review from WilliamBZA July 6, 2026 18:18
The audit entries were logged through source-generated methods with the
ECS JSON as a '{AuditEvent}' template parameter. Over OTLP that exports
the literal '{AuditEvent}' placeholder as the record body with the
document only in an attribute — backends that map body → message (e.g.
Elastic) show the placeholder and need a pipeline rule to lift the JSON.

Both audit logs now log the pre-rendered document as a plain-string
state: the OTLP record carries the JSON exactly once, as the body, with
no attributes. The NLog audit.json line and the ILogger contract
(categories, levels, event ids 1001/1002/2001/2002) are unchanged.
Verified against an OTel collector and against audit.json on disk.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants